go代码优化以及一系列bug查找

内存又告警了!?

本文主要记录前段时间go代码中一系列关于内存优化以及泄露的诊断过程,作为备忘,同时希望能够给各位带来启发。

现象描述

有两个服务J和H,J会定时从H当中同步数据D来进行逻辑判定,但是随着使用发现J的内存会越来越高,并且随着时间推移数据D也是缓慢增长的这就直接导致了J机器的压力越来越大。并且同步时间也越来越长,已经到了不得不优化的地步。

定位问题

当J启动的时候最开始只会占用100M左右的数据,观察其内存走势图,在首次数据同步并且build数据之后会变为7G,第二次数据传输完后是12.6G build之后是14.6G,第三次传输结束后是15.1G build之后仍然是15.1G左右内存基本稳定,但是随着使用内存会像24G大关逼近,相比之下H服务的内存稳定在5G左右,是由于go gc回收的问题导致了大块内存占用未及时释放导致,简单看了下go的内存回收策略,讲真看完觉得从gc方向优化空间并不大。之后经过讨论决定从数据层面进行优化。

优化过程

之所以觉得gc不是最好的方向是因为数据本身就是5G,当新旧数据发生更新的时候,此时在服务当中是会有D~1~,D~2~两份数据存在的,这就直接导致内存发生翻倍,直到被回收掉,当时改为手动执行gc发现需要10s之久,这个是不能接受的。

在同步的5G数据里面其实并不是全部都有用的,经过统计发现,获取到的数据D原本是个数组经过build之后成为字典,字典的key数量是100W量级的,但是在每个J实例当中实际用到的key的数量平均有10W左右!当然了在字典当中key只占有很小的一部分内存大头是value占用的,但是这起码是个方向不是!

由于涉及到数据集的问题,所以这边调整了J/H的通信数据,每次J将自己需要的数据子集发送给H,H经过筛选build之后将数据发回给J,经过实验发现J的内存压力确实小了!!最终的使用过程中稳定在了4G和原来差了将近18、9G左右!!

然而,然而。。。H的内存压力直接翻倍。。从原来的5G左右,直接翻到了14G(因为数据时5分钟重新装载一次所以在gc回收之前可能会有多份数据存在,其中又涉及到给各个J实例发送build数据),距离16G也已经很近了。。。这就很尴尬了。。。

先是把J服务的优化结果告知其他同事和leader之后他们都很高兴,紧接着说了H都沉默不语了🤣,他们提出来不行就升级机器或者拆分,但是我总觉得在最近一段时间在看代码的时候,有多处可以使用指针的地方,最后都没有使用,当时读的时候只觉得效率低一些,联系到今天内存占用比较高瞬间觉得,如果把其中一些值改为指针而不是变量实例,那么应该还有一部分提升空间,于是仔细研究了一下占用大量内存的数据结构。

发现占用大量内存的map的value是如下一个数据结构

1
2
3
4
5
6
7
type mapValue {
id int
m string
...
...
Tpl *Template
}

经过仔细确认,发现每一个mapValue除了最后一个字段一定不一样之外,其他字段有非常高的重叠率,大概是10:1,瞬间有了方案,新增了如下一个数据结构,这样在每次装载数据的时候,就不在使用mapValue里面的Tpl字段,而是使用如下一个字段来进行存储,经过一段时间的观察H服务成功稳定在了8G

1
2
3
4
type mapValueOpt {
m *mapValue
t *Template
}

优化完这两个服务别提多高兴啦,哈哈哈,服务J直接从最高20G+变成了4G,H服务从5G->15G->8G

手里拿着🔨,看什么都是钉子

刚优化完这两个服务,随即又奔向了该服务家族的T服务,T服务更加明显,内存是一个有明显斜率向上奔走的波浪线,这明显是有哦内存泄露啊,还等什么?撸袖子就准备干。

经过仔细调研,发现T服务主要代码逻辑就是收到一批数量D,之后将数据分别发现J/M/G服务,类似于一个带有缓存的Proxy,于是先看了缓存部分的代码,使用的是开源的vector库,仔细看了看,也没有什么明显的使用错误,这一块儿就跳过了。

之后怀疑是不是T在发送给其他三个服务的时候序列化的时候出的问题呢?于是分别注掉相关部分的代码,bingo!内存稳定了!!!还在等什么!!这一定是因为rpc调用使用的json库效率太低导致的!!于是将rpc调用部分的编码方式修改为了msg,诶!奇迹发生了!内存基本稳定住了,但是还是会有少许斜率只是斜率变小了,照这个速度还是会有一天内存会💥啊,于是跟同事商量,同事说这样就可以了,毕竟我们会有上线,这个时间段足够我们上线重启了,额,,,总觉得哪里不太对,但是确实还有其他事要忙,那就先这样吧。。。😂,但是心里仍然觉得不太对哟。觉得没有找到根因,毕竟json库用的人那么多如果真的是因为这个序列化的问题那网上早吐槽死了。

Finally

果然,过了一个月发现!内存又承不住了,并且这次斜率比前两次都大!!!这时才确认一定不是序列化的问题,毕竟序列化之前的json后面的msg不可能都有这个低级的gc问题,那么是怎么回事呢!!于是又开始了查找定位,在查阅资料的时候,偶然间瞥到有人使用pprof定位了一出线程溢出的问题,我突然想,这个有没有可能也是呢!于是打开了调试界面!!高潮发生了!!尼玛竟然有14W个线程?!What????还以为自己眼花了,于是一个一个数了好几遍!最后发现就是,根据调试信息,定位到了代码段,发现是在rpc调用处的超时控制写的有问题,这也就是第一次定位问题注释掉rpc调用的代码会让内存稳定的原因!!

如下错误的:

1
2
3
4
5
6
7
8
c := make(chan error)
go func() { c <- client.Call("Service.Method", args, &reply) } ()
select {
case err := <-c:
// use err and reply
case <-time.After(timeoutNanoseconds):
// call timed out
}

解释一下,当有超时发生的时候,创建的call协程会尝试向c管道写入一条error,然而此时上层的函数已经在time.After进行了返回,selece不会在消费c管道,因此造成了协程阻塞在管道写入阶段!!!随着超时情况的发生T服务的协程越来越多,直接导致了内存越来越高。

正确的使用方式应该是使用异步的channel,c := make(chan error,1),这样即便是超时发生不会有人消费channel 协程也能正常返回了!!

之后外层函数返回,协程也结束了,c由于已经没有人使用和写入也会被系统回收,完美!

所以你看,第二次的问题根本不是内存问题,而是线程泄露,最开始的方向都是错的

感想

优化是一个亘古不变永恒的主题,只要程序一天存在,并且再发展,那么总有一天会到达性能瓶颈,此时性能优化也就显得尤为重要了,所以我还是喜欢从一开始就用指针!哈哈哈

转载请注明来源链接 http://just4fun.im/2018/05/05/memory optimize and routine leaks/ 尊重知识,谢谢:)